-
Notifications
You must be signed in to change notification settings - Fork 10.1k
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Adds HttpLogging middleware #31816
Adds HttpLogging middleware #31816
Conversation
src/Middleware/HttpLogging/src/HttpLoggingServicesExtensions.cs
Outdated
Show resolved
Hide resolved
We need to do an api review |
For sure; I'm scheduling one for tomorrow/friday one off. |
Thank you for submitting this for API review. This will be reviewed by @dotnet/aspnet-api-review at the next meeting of the ASP.NET Core API Review group. Please ensure you take a look at the API review process documentation and ensure that:
|
private readonly IOptionsMonitor<HttpLoggingOptions> _options; | ||
private const int DefaultRequestFieldsMinusHeaders = 7; | ||
private const int DefaultResponseFieldsMinusHeaders = 2; | ||
private const string Redacted = "X"; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
[Redacted] instead of X
/// <summary> | ||
/// Maximum request body size to log (in bytes). Defaults to 32 KB. | ||
/// </summary> | ||
public int RequestBodyLogLimit { get; set; } = 32 * 1024; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Do we need Size in this name? We have size everywhere else in Kestrel.
long RequestBodySizeLimit
long ResponseBodySizeLimit
Why didn't we go with longs, we didn't learn from IIS 😄
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
It's a long in Kestrel. I can only imagine the logs with 2 GB+ bodies inside 😆
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
We could even make it nullable for consistency with Kestrel. Why force an upper bound of 2^63 bytes!
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Is this a serious conversation? I guess we can make it a long....
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
OK we can leave it as an int and rename it to SizeLimit
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
We covered this in the API review and picked LogLimit over SizeLimit. In kestrel it's an absolute size limit and exceeding it causes the request to fail. Here it's a limit on the amount that will be logged before we truncate.
You really want to support GB of logged data? We'll definitely need to switch to a chunking/streaming model then to avoid buffering the whole thing.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Lets stick with an int (2GB is still GB) but I think Size should be in the name. It's the size of the request and response body in bytes.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I agree with @Tratcher, unless we have a name like RequestBodyLogSizeLimit
which seems needlessly verbose.
/// <param name="contentType">The content type to add.</param> | ||
public void AddBinary(string contentType) | ||
{ | ||
throw new NotSupportedException(); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
What's the deal here?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Wanted to have the APIs present for binary logging format, which are currently not supported.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
RequestBufferingStream? requestBufferingStream = null; | ||
Stream? originalBody = null; | ||
|
||
if ((HttpLoggingFields.Request & options.LoggingFields) != HttpLoggingFields.None) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I notice we don't check if Logging is enabled before we do any of this stuff. Seems like we should no?
|
||
// Afterwards, we need to call convert in a loop until complete is true. | ||
// The first call to convert many return true, but if it doesn't, we call | ||
// Convert with a empty ReadOnlySequence and flush: true until we get completed: true. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Why? There's no more data coming in right?
|
||
private static readonly Action<ILogger, Exception?> _unrecognizedMediaType = | ||
LoggerMessage.Define(LogLevel.Debug, new EventId(6, "UnrecognizedMediaType"), "Unrecognized Content-Type for body."); | ||
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
nit: Remove space
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
LGTM
I did a bunch of perf runs locally to generally get a picture of what's going on. With a custom logging provider which noop'd (to remove the impact of the actual logging), I saw around a 3% regression with logging the request, response, and response body. Before (no HttpLoggingMiddleware)
After (with middleware and noop logging)
I averaged a few runs here and in general, removing the middleware showed around a 3% gain, which is expected. I'm going to try some worst case scenarios just for kicks now. But there isn't anything obscenely wrong perf wise. |
To no surprise, a larger response body affects perf even more, seeing around a 40% regression. Writing a 50 KB response, perf numbers go from 21k RPS to 13K RPS.
|
Buffering the bytes shouldn't cause much throughput overhead(?). Is it the decoding and logging a big string that slows it down? I suspect streaming/chunked body logging will help here. |
Yeah there are many things we can do to improve perf here, but that's for after this PR is merged 😄 . I mostly wanted to make sure there wasn't something horrendously wrong. |
Console logging pushes to a BlockingCollection which will hold a few items before blocking more logs. So once the queue is full, it completely blocks the thread. |
Copying the body will have CPU overhead and decoding UTF8 will have even more CPU overhead. |
This isn't logging to console atm, it's nooping that portion. This is to primarily check the perf of the middleware and buffering. |
Oh, that doesn't seem great then 😄 |
@dotnet/aspnet-build please merge. |
Fixes #3700
There are a few follow up issues that I'll file:
I'll write the API proposal in the issue linked with the information here.
There are a few tests failing ATM as I have some questions that review will help with.